Skip to content

Conversation

JDevlieghere
Copy link
Member

@JDevlieghere JDevlieghere commented Oct 6, 2025

Compute the start time before registering the callback, rather than after, to avoid the possibility of a small race.

The following scenario illustrates the problem.

  1. The callback is registered with a 2 second timeout at t=0ms.
  2. We compute the start time after registering the callback. For the sake of argument, let's say it took 5ms to return from registering the callback and computing the current time. Start=5ms.
  3. The callback fires after exactly 2 seconds, or t=2000ms.
  4. We compute the difference between start and now. If it took less than 5ms to compute, then we end up with a difference that's less than 2000ms and the test fails. Let's say it took 3ms this time, then 2003ms-5ms=1998ms < 2000ms.

The actual values in the example above are arbitrary. All that matters is that it took longer to compute the start time than the end time. My theory is that this explains why this test is flaky when running under ASan in CI (which has unpredictable timing).

rdar://160956999

Compute the start time *before* registering the callback, rather than
after, to avoid the possibility of a small race.

The following scenario illustrates the problem.

1. The callback is registers with a 2 second timeout at t=0ms.
2. We compute the start time after registering the callback. For the
   sake of argument, let's say it took 5ms to return from registering
   the callback and computing the current time. Start=5ms.
3. The callback fires after exactly 2 seconds, or t=2000ms.
4. We compute the difference between start and now. If it took less than
   5ms to compute, then we end up with a difference that's less than
   2000ms and the test fails. Let's say it took 3ms this time, then
   2003ms-5ms=1998ms < 2000ms.

The actual values in the example above are arbitrary. All that matters
is that it took longer to compute the start time than the end time. My
theory is that this explains why this test is flaky when running under
ASan in CI (which has unpredictable timing).

rdar://160956999
@llvmbot
Copy link
Member

llvmbot commented Oct 6, 2025

@llvm/pr-subscribers-lldb

Author: Jonas Devlieghere (JDevlieghere)

Changes

Compute the start time before registering the callback, rather than after, to avoid the possibility of a small race.

The following scenario illustrates the problem.

  1. The callback is registers with a 2 second timeout at t=0ms.
  2. We compute the start time after registering the callback. For the sake of argument, let's say it took 5ms to return from registering the callback and computing the current time. Start=5ms.
  3. The callback fires after exactly 2 seconds, or t=2000ms.
  4. We compute the difference between start and now. If it took less than 5ms to compute, then we end up with a difference that's less than 2000ms and the test fails. Let's say it took 3ms this time, then 2003ms-5ms=1998ms < 2000ms.

The actual values in the example above are arbitrary. All that matters is that it took longer to compute the start time than the end time. My theory is that this explains why this test is flaky when running under ASan in CI (which has unpredictable timing).

rdar://160956999


Full diff: https://github.com/llvm/llvm-project/pull/162197.diff

1 Files Affected:

  • (modified) lldb/unittests/Host/MainLoopTest.cpp (+1-1)
diff --git a/lldb/unittests/Host/MainLoopTest.cpp b/lldb/unittests/Host/MainLoopTest.cpp
index 0bc291c26b9c9..ae16d02101819 100644
--- a/lldb/unittests/Host/MainLoopTest.cpp
+++ b/lldb/unittests/Host/MainLoopTest.cpp
@@ -424,9 +424,9 @@ TEST_F(MainLoopTest, ManyPendingCallbacks) {
 
 TEST_F(MainLoopTest, CallbackWithTimeout) {
   MainLoop loop;
+  auto start = std::chrono::steady_clock::now();
   loop.AddCallback([](MainLoopBase &loop) { loop.RequestTermination(); },
                    std::chrono::seconds(2));
-  auto start = std::chrono::steady_clock::now();
   ASSERT_THAT_ERROR(loop.Run().takeError(), llvm::Succeeded());
   EXPECT_GE(std::chrono::steady_clock::now() - start, std::chrono::seconds(2));
 }

@JDevlieghere JDevlieghere merged commit 605e2d1 into llvm:main Oct 7, 2025
11 checks passed
@JDevlieghere JDevlieghere deleted the rdar160956999 branch October 7, 2025 19:45
JDevlieghere added a commit to swiftlang/llvm-project that referenced this pull request Oct 7, 2025
…llvm#162197)

Compute the start time *before* registering the callback, rather than
after, to avoid the possibility of a small race.

The following scenario illustrates the problem.

1. The callback is registered with a 2 second timeout at t=0ms.
2. We compute the start time after registering the callback. For the
sake of argument, let's say it took 5ms to return from registering the
callback and computing the current time. Start=5ms.
3. The callback fires after exactly 2 seconds, or t=2000ms.
4. We compute the difference between start and now. If it took less than
5ms to compute, then we end up with a difference that's less than 2000ms
and the test fails. Let's say it took 3ms this time, then
2003ms-5ms=1998ms < 2000ms.

The actual values in the example above are arbitrary. All that matters
is that it took longer to compute the start time than the end time. My
theory is that this explains why this test is flaky when running under
ASan in CI (which has unpredictable timing).

rdar://160956999
(cherry picked from commit 605e2d1)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants